Audit of warn! and error! - #5640
Conversation
| .map_err(|e| { | ||
| // TODO: Review log level after user SQL errors can be distinguished from internal database failures. | ||
| log::warn!("{e}"); | ||
| (StatusCode::BAD_REQUEST, e.to_string()) |
There was a problem hiding this comment.
Same as other areas we might want to split this up so we can use error! if there is a database failure.
There was a problem hiding this comment.
Can you create a follow-up ticket?
There was a problem hiding this comment.
Follow-up created: #5690
I did go down the rabbit-hole of all the possible issues and decided to make the follow-up simple instead of declaring all possible areas of concern.
| // TODO: Review each caller and split this helper by the appropriate log severity. | ||
| pub fn log_and_500(e: impl std::fmt::Display) -> ErrorResponse { | ||
| log::error!("internal error: {e:#}"); | ||
| (StatusCode::INTERNAL_SERVER_ERROR, format!("{e:#}")).into() |
There was a problem hiding this comment.
This seems to be very broadly used which makes it hard to know if it should be reduced from error! my gut reaction is to change it to warn! and slowly clean up it's use?
There was a problem hiding this comment.
Please change to warn for now, and any place you're already editing that has a log_and_500 directly next to its own more specific log line, remove the log_and_500 call and replace with directly returning the error response. You may want to move the error response into a new helper function.
| // TODO: Review log level after configured issuers can be distinguished from arbitrary token issuers. | ||
| log::warn!("Error fetching public key for issuer {raw_issuer}: {e:?}"); |
There was a problem hiding this comment.
This one I'm not 100% sure if we need to split up or count everything as warn!
There was a problem hiding this comment.
I have no clue. At this stage I'm unconcerned.
| // TODO: Review log level after migration/user errors can be distinguished from internal database failures. | ||
| log::warn!("Database update failed: {} @ {}", e, stdb.database_identity()); | ||
| system_logger.warn(&format!("Database update failed: {e}")); | ||
| let (_, tx_metrics, reducer) = stdb.rollback_mut_tx(tx); |
There was a problem hiding this comment.
Another spot where it looks like real failures can be mixed in with user issues.
| // TODO: Review log level after guest view errors can be distinguished from materialization failures. | ||
| log::error!("Error materializing view `{view_name}`: {err:?}"); | ||
| ViewOutcome::Failed(format!("Error materializing view `{view_name}`: {err}")) |
There was a problem hiding this comment.
This one looked similar as above but I'm not certain if it's true that it can be mixed here.
There was a problem hiding this comment.
Another follow-up ticket? And, can @joshua-spacetime weigh in as to whether user errors can happen here, which I assume would be if a view function panics.
There was a problem hiding this comment.
Yes if a view function panics. Primary key violations too.
There was a problem hiding this comment.
Ok, then we should drop this to warn.
There was a problem hiding this comment.
Dropped to warn and added a follow-up: #5692
|
FYI #5320 is about to merge which tweaks some logs as well |
Signed-off-by: Jason Larabie <jason@clockworklabs.io>
| .map_err(|e| { | ||
| // TODO: Review log level after user SQL errors can be distinguished from internal database failures. | ||
| log::warn!("{e}"); | ||
| (StatusCode::BAD_REQUEST, e.to_string()) |
There was a problem hiding this comment.
Can you create a follow-up ticket?
| // TODO: Review each caller and split this helper by the appropriate log severity. | ||
| pub fn log_and_500(e: impl std::fmt::Display) -> ErrorResponse { | ||
| log::error!("internal error: {e:#}"); | ||
| (StatusCode::INTERNAL_SERVER_ERROR, format!("{e:#}")).into() |
There was a problem hiding this comment.
Please change to warn for now, and any place you're already editing that has a log_and_500 directly next to its own more specific log line, remove the log_and_500 call and replace with directly returning the error response. You may want to move the error response into a new helper function.
| // TODO: Review log level after configured issuers can be distinguished from arbitrary token issuers. | ||
| log::warn!("Error fetching public key for issuer {raw_issuer}: {e:?}"); |
There was a problem hiding this comment.
I have no clue. At this stage I'm unconcerned.
| Some(ptr) => self.delete(ST_CLIENT_ID, ptr).map(drop)?, | ||
| _ => { | ||
| log::error!( | ||
| log::warn!( |
There was a problem hiding this comment.
@joshua-spacetime how can this (and the other previously error! logs in this file) happen, and how bad is it?
There was a problem hiding this comment.
Not bad. They only happen if the row is missing, which just means it was cleaned up previously. They don't need to be error logs.
There was a problem hiding this comment.
How about we drop to info, then?
There was a problem hiding this comment.
Switched this to info
| } | ||
| Err(e) => { | ||
| // TODO: Review log level after retryable cleanup errors can be distinguished from internal database failures. | ||
| log::error!( |
There was a problem hiding this comment.
What user errors can get mixed in here?
There was a problem hiding this comment.
I've removed the comment.
This was poorly written and I'm not sure it's that useful after a re-review. The clear_expired_views can error if lookup_st_view() fails which can mean the view is already cleared. That would be the only case I can see here that it could be warn or lower.
| let res = self | ||
| .maybe_take_snapshot(database_state.as_ref()) | ||
| .await | ||
| // TODO: Review log level after lifecycle errors can be distinguished from snapshot creation failures. |
There was a problem hiding this comment.
Please create a follow-up ticket.
| // TODO: Review log level after client SQL errors can be distinguished from internal database failures. | ||
| log::error!("PG: Error for database {database}: {err}"); |
There was a problem hiding this comment.
Downgrade to warn, at least until the TODO is done. Please make a follow-up ticket, but mark it P3.
There was a problem hiding this comment.
Changed to warn and added follow-up: #5695
| // TODO: Do not log the supplied password/token; then classify credential errors separately from provider failures. | ||
| log::error!( |
There was a problem hiding this comment.
Please downgrade to warn, and make a P3 follow-up, as above.
There was a problem hiding this comment.
Changed to warn and added follow-up: #5696
Description of Changes
Reviewed all warn! and error! lines for host side issues to get ready for alerting.
API and ABI breaking changes
No breaking changes.
Expected complexity level and risk
1 - Only changes to logging
Testing
cargo testagainst impacted crates